fixed an error handling in bench_latency.py - #904
Conversation
- see before and after below.
There was a problem hiding this comment.
Currently, it is impossible to see if self.tree_cache is None. The bench_latency file is a hacky way of running model inference using low-level APIs, which skips the step of creating tree_cache.
However, it is also a concern that the --disable-radix option only skips the computation at the lowest level and does not remove everything like tree_cache. It might be better to turn off everything, but in that case, there might not be only one place to change. We are also planning to refactor the tree_cache in a more modular way.
Regardless, the current change is correct and could be part of the complete change. What do you think? @merrymercy
|
for benchmarking, maybe it is actually good to be able to run without the cache? That should make the benchmark more deterministic and not affected by caching? IMHO, it is better to have the ability to run things with least dependencies unless tree cache is such a core thing and srt simply can't run without it? |
Yes, agree. |
Modify Multimodal Pressure Test Parameters in the Adaptation Scripts.
…d never joined the transfer that fills it) into the flip train
…, so 411 declines have no verdict Routing from the write-side agent (sgl-project#872) narrowed Posten 0 correctly: the store is healthy, 24277 canonical pages live during the R7 window, and the historic "store is empty" readings probed a path this boot does not use. So the 671 refused walks are a MATCH problem, not a content problem. The question that follows immediately is the one nobody could answer: a walk that matches nothing should fall through to an L3 prefetch, and prefetch was attempted on only 264 of 675 sampled walks. THE OBVIOUS ANSWER IS WRONG, and the code says why. It is tempting to read the 411 as the same MambaComponent refusal declining twice -- one root, two numbers. It is not: * The prefetch anchor IS mamba-gated, but by an aliasing the base contract does not describe. base_prefix_cache.py:201-210 separates `last_host_node` (the L3 prefetch anchor) from `best_match_node` (the validator-consensus L2 anchor) -- two fields, two purposes. UnifiedRadixCache sets them equal under HiCache (unified_radix_cache.py:1443-1449). Deliberate and commented, but it contradicts the field's own documentation, and two fields that are documented different and implemented identical are a drift source (sgl-project#747's shape). Named, not changed here. * Even so, the refusal does NOT decline the prefetch. Total refusal leaves best_match_node at the root, and the caller admits the root on purpose: `locally_eligible = last_host_node.backuped or last_host_node is self.tree_cache.root_node` (scheduler.py:4933-4935). A cold request with no match is supposed to prefetch. The first term holds. * The second term (>= 256 new tokens) holds for agent prompts of thousands. That leaves the rate limiter -- AND THERE THE EVIDENCE STOPS, which is the actual finding. None of the three terms is counted or logged. The 411 declines are silent. Nobody can attribute them from this boot, and no amount of re-reading the log will change that. eligible = (locally_eligible and prefetch_length >= self.prefetch_threshold and not self.cache_controller.prefetch_rate_limited()) Three unrelated verdicts wearing one boolean, remedies in three different files. The sgl-project#914 shape one module over: blame without a defect. So this is an instrument and NOT a policy change. The three terms are the same three, evaluated in the same order, with the same outcome; `eligible` is now `reason is None`, one expression, so the predicate and its explanation cannot drift apart the way sgl-project#747 records these very lineages drifting. The first failing term is named rather than all of them -- a request can trip several, and summing them would double-count exactly as `refused_tokens_by_component` is documented to. Not env-gated, unlike the sgl-project#904 match census. That one builds an object and walks validators a second time, so it pays for itself only when armed. This is one integer increment on a path that already builds a RadixKey and takes a host lock -- and a counter you must remember to arm cannot answer "was it ever tried", which is the whole question. `attempted` is counted alongside the refusals so the denominator is local (sgl-project#873: a denominator reconstructed from another log is how a narrowed candidate set reads as a decomposition), and an unrecorded gate says "no observation" rather than a silent zero (sgl-project#829). HYPOTHESIS, RECORDED AS ONE. prefetch_capacity_limit is `0.5 * mem_pool_host.size` (cache_controller.py:729), and that size is not constant across a phase flip: sgl-project#905 measured the two host tiers at 703472 rows (PP) and 30518 (TP), 23x apart, putting the TP-phase budget near 15259 tokens -- under four prefetches of the 4096 this window actually completed, against 5 concurrent requests per flip. The order of magnitude fits 411/675, and I am deliberately not fitting it exactly: the PP phase has ample budget, so the number cannot come from there alone. If it holds, the same host-tier asymmetry behind sgl-project#905's double-free is also starving the TP-phase prefetch budget -- one defect, two effects, to be checked rather than assumed. The counter decides it on the next boot instead of re-arguing it. RED-FIRST, four mutants, each red, restored green (14 tests): revert to the shipped conjunction (no counter) ......... 4 failed eligible computed twice instead of derived from reason . 2 failed attempts not counted (denominator lost) ................ 2 failed no-observation reported as attempted=0 ................. 1 failed ONE SELF-INFLICTED DEFECT, found and fixed in the same pass, recorded because the form is evidently easy to commit. My first version of test_the_rate_limit_check_is_still_called_at_most_once counted occurrences in the function's RAW source and went red because a PRE-EXISTING comment at :2674 mentions `prefetch_rate_limited()`. That is the sgl-project#908 substring defect -- prose used to reach a verdict about code -- in a test of mine, an hour after I rejected the same form in someone else's patch. Comment lines are now stripped before counting. GATE test/registered/unit/mem_cache serial, CVD="": 3 failed, 1950 passed, 1658 skipped. Both axes agree (summary 3, ANSI-stripped extraction 3). Two are test_acceptance_emitters_758::RefillTiming, baseline-proven pre-existing earlier in this branch; the third is test_pool_invariant_double_owned_912, a concurrently-developed test belonging to sgl-project#912 and untouched by this commit. The sgl-project#904 census suite is green against this change (62 passed together with the sgl-project#913/sgl-project#914/sgl-project#915 suites), which is the regression that matters: note_refused gained an optional third argument and its existing callers must not care.
The census (/spinning/gpu-arb/CENSUS_1035_readthrough_chain.md) listed every gate on the read-through chain with its instrument or BLIND. Three BLIND rows needed no new mechanism, only exposure, and all three share one shape: a gate that can ZERO the read path while printing nothing, so a boot where it fired and a boot where storage was simply cold produce identical logs. That is how this campaign measured "#cached-token: 0" for weeks without being able to say which link produced it. R11 -- unified_radix_cache.py, sgl-project#841 host-only insert declined. This is the sgl-project#841 law itself: it marks the whole fetched tail unclaimed and returns. It logged at logger.DEBUG, i.e. INVISIBLE on every boot this strand runs. Raised to warning, rate-limited, and the line now says the declined tail is released rather than published. Cheapest row on the list: a level hub, no new logic. The counter it increments already existed. R13 -- hicache_storage.py, empty KV prefix. #1028B fires only when a COMPONENT cap moved the number (final_pages != kv_pages). When the KV prefix is itself 0 the claim is already zero and NOTHING printed, so "storage genuinely holds nothing for this key" and "everything is fine" were the same log. Now named as an honest cold miss, explicitly distinguished from a capped claim. W12 -- staging_write_ring.py, refused admission. refused/refused_tokens have been maintained all along, but stats() -- their only exposure -- has ZERO callers in the tree, so a write-through page refused for want of staging room left no trace anywhere. Nothing can be READ back that was never WRITTEN, which makes a silent write-side refusal indistinguishable from a read-side miss to whoever debugs the read path afterwards. Emitted at the refusal itself rather than waiting for a reporting site to be invented. NOT built, named only (register lines, per the census): R6 symmetric participation vote returning zero silently; R15/R16 match validators and dead-node stop (sgl-project#904 exists but is unarmed); W9 -- under write_through _evict_device_leaf DELETES a childless node outright, taking its mamba anchor with it, which is a correctness candidate in its own right and not an instrumenting job. Check: the failure class here is a NameError on a logger or on an uninitialised rate-limit attribute, so the check was py_compile on all three files, a grep asserting each module defines `logger`, and an AST scope check that every name the three new emitters reference (keys, tokens, matched_length, total_len, node) is genuinely bound in its enclosing function. All pass.
… per cutover wave The emission gate was `_dpc_emitted % every == 0` on a process-lifetime counter with `every` = the shared sgl-project#904 knob (default 64), so the FIRST [sgl-project#939 double-prefill] line of a boot needed the 64th recording call. Measured on boot_855_weg1b2 (2026-09-02): two readmit waves, a handful of calls, ZERO lines -- and the acceptance read that absence as "half B is not wired" instead of as a rate limit it could not clear. The section-5 contract is ONE CENSUS PER CUTOVER, so the floor is one LINE per cutover wave: `_dpc_wave_emitted` forces the first observation after `reset_double_prefill_census` (the only thing that ends a census) out, and the periodic sampling plus the always-on breach rule are unchanged on top. Also documents the launcher knob HICACHE_EXTRA (sgl-project#810 store watermark, default {"max_size":"200G"}) in docs/dev/WEG1_1068.md section 4; the tree refuses staging without a watermark (lru_file_evictor.py:151) and boot weg1b1 died on exactly that. Evidence (DESK-PROVEN, hermetic, CUDA_VISIBLE_DEVICES=""): red on 8bf12cf: 2 failed ("0 not greater than or equal to 2 ... from 2 waves") green with the fix: 2 passed mutant (drop the wave-flag reset in reset_double_prefill_census): 1 failed ruff check: All checks passed! ruff format --check: 2 files already formatted
…NG_ANTHROPIC_INLINE_SYSTEM_IN_PLACE, default off) Claude Code 2.1.280 sends mid-conversation role:"system" messages (api_system: tool additions/removals, output_config). With the Qwen3.8 template (head-only system turn) the Anthropic adapter hoisted them into the head system turn, so the first turn that carries one re-renders every token behind the system text. Measured on D: radix sgl-project#1420 WALK-STOP and the arena key chain (sgl-project#1439 leading_complete) both stop at the end of the system turn -- depth 3876 (dkr27bnvfp4bar1agent09252328, weg2-14-16/-17) and 4655 (dkr27bbar1final09260145, weg2-12-12), stored (13,248046)=".<|im_end|>", new (13,198)=".\n" (the "\n".join of the hoist). The sgl-project#904 census then reads MambaComponent:absent at that depth, X-GATE W31, X-REQUEUE, one P epoch. The front's request_text renders the same message in place and credits the whole previous turn (presence_span 19335/20168), so it routes SHORT. Switch on: non-leading inline system messages become a user turn at their position, wrapped in <system-reminder>; the leading run is still merged into the head. Must be set identically on P and D (handoff keys are P's tokenization). Off = byte-identical to before. Tests (test27b.sh, CPU): test_inline_system_in_place.py 5 passed (off pins the break at ".\n", on pins turn N as a rendered prefix of turn N+1); anthropic/test_serving.py + test_anthropic_557.py + test_anthropic_rid_h90.py + weg2/test_weg2_messages_wire_rc7_0925.py: 100 passed together. UNIFY (UN6, Operator 26.09.): pick of desk/27b-mambaend-0926 (2303948, MZ, base 0644c6f) after the sgl-project#49-rest port, clean. dup_defs_gate: 0 new. test27b.sh: test_inline_system_in_place + anthropic/test_serving + test_anthropic_557 + test_anthropic_rid_h90 91 passed, 9 subtests.
…fork, not at N-1 (--fork-anchor-token, default off) Boot dkr27brc10bar1agent09261821: 9 of 78 D-direct requests prefilled 1.2k-4.7k tokens (weg2-12-17, 16-24, 20-31, 20-32, 22-36, 22-42, 24-44, 26-55, 26-67). Each is a SIBLING of a request just served: same chat up to the predecessor's last message, then another ~155-token message instead of the generation prompt <|im_start|>assistant\n<think>\n (5 tokens). D's own match names the fork: sgl-project#904 reached=31441 against weg2-10-14's 31446 (41677/41682, 48867/48872, 73895/73900, 89902/89907 -- always N-5). P's only tail anchor is the END anchor at N-1 (P-TRIM-END-ANCHOR, trim=1), 4 tokens past the fork, so the read fell back to the previous anchor (#1028B FETCH CAP kv=31441 claimed=27384 caps={mamba: 27384}). 8 of 9 arrived while the predecessor was still decoding; no anchor at "prompt + generated" existed or would have helped (next turns re-render the output: 26-57 claimed 73898 = P's end anchor of 24-54, not D's finish anchor at 74752). 26-67: D's own prefill track of 26-66 landed at N-1 (extend 1025 = 16*64+1). Switch SGLANG_WEG2_FORK_ANCHOR_TOKEN=<id> on both groups (launcher --fork-anchor-token 248045, needs --p-trim-end-anchor; unset = byte-identical): * P intake cuts a leg-1 prompt at the last fork token of its final 16 ids (N-5 on Qwen3.x) instead of N-1 -- no forward added, D extends 6 tokens instead of 2 in the leg-2 extend it runs anyway; * D's store read ends at the same cut (pure function of ids + env, same on every rank): a fork-cut leg-2 read lands complete, no sgl-project#1324 deferral; * D's extend track of the step reaching the prompt end stays at or below the fork (h at (t-prefix)/64, relative grid; extend only, never decode). Tests (test27b.sh, CPU): new test_weg2_fork_anchor_0926.py 18 passed; red on c51591f (13 failed / 4 passed: the switch had no effect). Real UnifiedRadixCache uni+bigram: sibling claim 0 -> the fork with P's state; D leg 2 resumes at the fork. Affected files 173 passed (trim, tail fold, end anchor hold, store-short, deferral, hold-refetch, dormant hold, P intake, launcher argv). Broader sweep: 471 passed, 15 failed identically on base (gloo tests 580/943b/1290, pre-existing).
when running the latency benchmark on a L4 with 24GB of VRAM, the error was not well handled. See before and after below:
before:
after